Improve the profiling output of Cargo
authorAlex Crichton <alex@alexcrichton.com>
Mon, 9 Mar 2015 16:45:40 +0000 (09:45 -0700)
committerAlex Crichton <alex@alexcrichton.com>
Mon, 9 Mar 2015 16:45:40 +0000 (09:45 -0700)
* Don't use `{:?}` in profiling output, it's too noisy
* Allow an integer to be specified with `CARGO_PROFILE` indicating how many
  levels deep should be printed.

src/cargo/core/resolver/mod.rs
src/cargo/ops/cargo_rustc/fingerprint.rs
src/cargo/util/profile.rs

index 3bd5cf6c1a19ddd493829b9ab964106a1108e6b6..ef581f0741edae6e86c1da2f65eca0c4c53c9803 100644 (file)
@@ -138,7 +138,7 @@ pub fn resolve(summary: &Summary, method: Method,
         activations: HashMap::new(),
         visited: Rc::new(RefCell::new(HashSet::new())),
     });
-    let _p = profile::start(format!("resolving: {:?}", summary));
+    let _p = profile::start(format!("resolving: {}", summary.package_id()));
     match try!(activate(cx, registry, &summary, method)) {
         Ok(cx) => {
             debug!("resolved: {:?}", cx.resolve);
index cc336e1144ce5523f5e09b311c2e406ea3582983..2ebf630f88124251567c574436839c63344ad937 100644 (file)
@@ -44,8 +44,8 @@ pub fn prepare_target<'a, 'b>(cx: &mut Context<'a, 'b>,
                               pkg: &'a Package,
                               target: &'a Target,
                               kind: Kind) -> CargoResult<Preparation> {
-    let _p = profile::start(format!("fingerprint: {} / {:?}",
-                                    pkg.package_id(), target));
+    let _p = profile::start(format!("fingerprint: {} / {}",
+                                    pkg.package_id(), target.name()));
     let new = dir(cx, pkg, kind);
     let loc = new.join(&filename(target));
 
index 100fd2c36c12baccaedf6be7eade3435c43bc11b..59cc83f45dc73733749d5d732865ee6de1880d90 100644 (file)
@@ -14,10 +14,12 @@ pub struct Profiler {
     desc: String,
 }
 
-fn enabled() -> bool { env::var_os("CARGO_PROFILE").is_some() }
+fn enabled_level() -> Option<usize> {
+    env::var("CARGO_PROFILE").ok().and_then(|s| s.parse().ok())
+}
 
 pub fn start<T: fmt::Display>(desc: T) -> Profiler {
-    if !enabled() { return Profiler { desc: String::new() } }
+    if enabled_level().is_none() { return Profiler { desc: String::new() } }
 
     PROFILE_STACK.with(|stack| stack.borrow_mut().push(time::precise_time_ns()));
 
@@ -28,14 +30,18 @@ pub fn start<T: fmt::Display>(desc: T) -> Profiler {
 
 impl Drop for Profiler {
     fn drop(&mut self) {
-        if !enabled() { return }
+        let enabled = match enabled_level() {
+            Some(i) => i,
+            None => return,
+        };
 
         let start = PROFILE_STACK.with(|stack| stack.borrow_mut().pop().unwrap());
         let end = time::precise_time_ns();
 
         let stack_len = PROFILE_STACK.with(|stack| stack.borrow().len());
         if stack_len == 0 {
-            fn print(lvl: usize, msgs: &[Message]) {
+            fn print(lvl: usize, msgs: &[Message], enabled: usize) {
+                if lvl > enabled { return }
                 let mut last = 0;
                 for (i, &(l, time, ref msg)) in msgs.iter().enumerate() {
                     if l != lvl { continue }
@@ -43,7 +49,7 @@ impl Drop for Profiler {
                              repeat("    ").take(lvl + 1).collect::<String>(),
                              time / 1000000, msg);
 
-                    print(lvl + 1, &msgs[last..i]);
+                    print(lvl + 1, &msgs[last..i], enabled);
                     last = i;
                 }
 
@@ -52,7 +58,7 @@ impl Drop for Profiler {
                 let mut msgs = msgs_rc.borrow_mut();
                 msgs.push((0, end - start,
                            mem::replace(&mut self.desc, String::new())));
-                print(0, &msgs);
+                print(0, &msgs, enabled);
             });
         } else {
             MESSAGES.with(|msgs| {